"""

.. module:: a2ptask
.. moduleauthor:: @author: 

This module includes all functionality for scraping data from SPEAR HTML.
   
.. seealso:: modules :mod:`<module>`

*Constants*:
.. data:: constant_1
        
    constant_1 is used for ......
        
.. data:: constant_2
        
    constant_2 is used for ......
"""

# Imports
#
import logging
from collections import deque
from threading import Thread
import time
import httplib
from HTMLParser import HTMLParser, HTMLParseError
from Queue import Queue
from datetime import datetime
import re

from runtime.task import Task
from runtime.spaces import SpacesContext
from datastore.database import DataStore, NotFoundException
from spear.http import HTTP
from datastore.resource import Resource
from datastore.uri import Uri
from runtime.boot import LoggingLevels

# Constants
#

# Classes
#

class A2PTask(Task):
    """The purpose of this class is ... 

    *Usage examples*::

        example code

    *Common Arguments for Class methods*:
        <arguments>
    
    *Audience*:
        <audience>
    
    *Constants*:
        .. data:: constant_1
        
            constant_1 is used for ......
        
        .. data:: constant_2
        
            constant_2 is used for ......
    """
    
    # Class constants
    #
    BINDING_NS_NAME_A2P = 'a2p'
    BINDING_NS_NAME_SPEAR = 'spear'
    BINDING_NS_NAME_OPERATION = 'op'
    
    def __init__(self, ds, spaces, task_uri, task_def_rs):
        # <purpose>
        #
        # Parameters:
        #     ds : datastore.database.DataStore
        #     spaces : runtime.spaces.Spaces - Reference to spaces
        #     task_uri : String - the uri for this task. The root uri will most
        #                likely be the 'binding' uri for this task.
        #     task_def_rs : datastore.resource.Resource - Task definition resource.
        #
        
        Task.__init__(self, ds, spaces, task_uri, task_def_rs)
        
        self.logger = logging.getLogger('eplanning.spear.a2ptask.A2PTask')
        self.logger.log(logging.DEBUG, "ds (%s), spaces (%s), task_uri (%s), task_def_rs (%s)" % (ds, spaces, task_uri, task_def_rs.pretty_print()))
        
        # Note: We are using collections::deque() rather than Queue::Queue() 
        #       because deque() supports an iterator where Queue() does not.
        #       We require an iterator to interrogate each queue to check if
        #       a request already exists on the queue.
        #
        self.immediate_queue = deque()
        self.background_queue = deque()
        
        self.login_request_rs = None
        self.poll_request_rs = None
        
        self.request_uri = None
        
    def cb_start(self, method, uri, new_uri, result, context, **kwargs):
        """This function is called when the task starts. 
        
        :param method: <class> or <type>
        :param uri: The task Uri.
        :param new_uri: <class> or <type>
        :param result: <class> or <type>
        :param context: <class> or <type>
        :param kwargs: <class> or <type>
        """

        time_uri = self.spaces.uri(Resource.BINDING_NS_NAME_TIME + ":")
        a2p_uri = self.spaces_context.uri(A2PTask.BINDING_NS_NAME_A2P + ':')
        
        # get the Spear request instruction list for logon. We'll need this a lot....
        #
        login_request_rs = self.get_spear_request_from_ds("req:login")
        self.logger.log(LoggingLevels.TRACE, "login_request_rs (%s)" % login_request_rs.pretty_print())
        
        # get the Spear request instruction list for poll. We'll need this a lot too....
        #
        self.poll_request_rs = self.get_spear_request_from_ds("req:poll")
        self.logger.log(LoggingLevels.TRACE, "poll_request_rs (%s)" % self.poll_request_rs.pretty_print())
        
        # start the task to process the queues
        #
        process_thread = A2PProcessThread(self.spaces, self.immediate_queue, self.background_queue, login_request_rs)
        process_thread.daemon = True
        process_thread.start()
        
        # start a poll timer - every 5 minutes.
        #
        cron_resource = Resource()
        cron_resource.interval = 300
        cron_uri = self.spaces_context.put(time_uri.add("cron").collection(True), cron_resource)
        
        self.spaces_context.watch(["put"], cron_uri.add("pop"), "cb_cron")
        self.spaces_context.process(a2p_uri.add("userrequest"), put="cb_process_user_request")
        self.spaces_context.process(a2p_uri.add("a2prequest"), put="cb_process_a2p_request")
#        self.spaces_context.watch_all(['put'], a2p_uri.add('requests').collection(True), 'cb_issue_a2p_request')
        
        return (False, None)
    
    def cb_stop(self, method, uri, res, result, context, **kwargs):
        """This function will stop any listeners still running.
        
        :param method: <class> or <type>
        :param uri: The task Uri.
        :param res: <class> or <type>
        :param result: <class> or <type>
        :param context: <class> or <type>
        :param kwargs: <class> or <type>
        """
        
        self.logger.log(LoggingLevels.TRACE, "method (%s), uri (%s), res (%s), result (%s), context (%s)" % (method, uri, res, result, context))
        
    def cb_cron(self, method, uri, new_uri, result, context, **kwargs):
        """This function is called when the cron timer goes off. Here we create
        a poll request and send it to ourselves.
        
        :param method: <class> or <type>
        :param uri: The task Uri.
        :param new_uri: Uri
        :param result: <class> or <type>
        :param context: <class> or <type>
        :param kwargs: <class> or <type>
        """
        
        self.logger.log(LoggingLevels.TRACE, "method (%s), uri (%s), new_uri (%s), result (%s), context (%s)" % (method, uri, new_uri, result, context))
        
        self.logger.log(LoggingLevels.TRACE, "adding poll request to background queue")
        self.add_request_to_background_queue(self.poll_request_rs)
        
    # TODO: Does the following method accept "res" or "new_uri"? 
    #
    def cb_process_user_request(self, method, uri, res, result, context, **kwargs):
        """This function is called to process user requests. Here we find 
        the appropriate list of Spear instructions and add to the immediate queue.
        
        :param method: <class> or <type>
        :param uri: The task Uri.
        :param res: <class> or <type>
        :param result: <class> or <type>
        :param context: <class> or <type>
        :param kwargs: <class> or <type>
        """
        
        self.logger.log(LoggingLevels.TRACE, "method (%s), uri (%s), res (%s), result (%s), context (%s)" % (method, uri, res, result, context))
        
        spear_uri = self.spaces_context.uri(A2PTask.BINDING_NS_NAME_SPEAR + ':')
        a2p_uri = self.spaces_context.uri(A2PTask.BINDING_NS_NAME_A2P + ':')
        
        # find the list of Spear instructions matching the user's request.
        #
        spear_request_uri = res.get_var(spear_uri.add("request").add("uri"))
        if (spear_request_uri is not None):
            request_rs = self.get_spear_request_from_ds(spear_request_uri)
            if (request_rs is not None):
                self.logger.log(LoggingLevels.TRACE, "found Spear request in datastore, adding to immediate queue. (%s) " % request_rs.pretty_print())
                
                # copy request arguments from user request.
                #
                if (res.has_var("arguments_dict")):
                    request_rs.set_var("arguments_dict", res.get_var("arguments_dict"))
                
                # The response Resource will be sent by 'A2PProcessThread'. Let's
                # tell it where to respond to.
                #
                request_uri = a2p_uri.add("requests").add(str(self.spaces_context.uuid()))
                request_rs.set_var("response_uri", request_uri)
                
                self.add_request_to_immediate_queue(request_rs)
                
                # return a copy of the uri as we dont want changes to the return uri by the caller to affect 
                # how we use the uri
                #
                return (True, request_uri.uri_copy())
            else:
                self.logger.log(logging.DEBUG, "no Spear request found in datastore for uri (%s)" % spear_request_uri)
        else:
            self.logger.log(logging.DEBUG, "request does not contain a Spear request")
        
        return (False, None)
    
    # TODO: Does the following method accept "res" or "new_uri"? 
    #
    def cb_process_a2p_request(self, method, uri, res, result, context, **kwargs):
        """This function is called to process requests generated by A2PTask. Here 
        we find the appropriate list of Spear instructions and add to the background
        queue.
        
        :param method: <class> or <type>
        :param uri: The task Uri.
        :param res: <class> or <type>
        :param result: <class> or <type>
        :param context: <class> or <type>
        :param kwargs: <class> or <type>
        """
        
        self.logger.log(LoggingLevels.TRACE, "method (%s), uri (%s), res (%s), result (%s), context (%s)" % (method, uri, res, result, context))
        
        spear_uri = self.spaces_context.uri(A2PTask.BINDING_NS_NAME_SPEAR + ':')
        
        # find the list of Spear instructions matching the user's request.
        #
        spear_request_uri = res.get_var(spear_uri.add("request").add("uri"))
        if (spear_request_uri is not None):
            request_rs = self.get_spear_request_from_ds(spear_request_uri)
            if (request_rs is not None):
                self.logger.log(LoggingLevels.TRACE, "found Spear request in datastore, adding to background queue. (%s)" % request_rs.pretty_print())
                self.add_request_to_background_queue(request_rs)
            else:
                self.logger.log(logging.DEBUG, "no Spear request found in datastore for uri (%s)" % spear_request_uri)
        else:
            self.logger.log(logging.DEBUG, "request does not contain a Spear request")
        
        # We've just put the request onto a queue to be processed by another task.
        # So we have nothing to return.
        #
        request_uri = self.task_uri.add("requests").add(str(self.spaces_context.uuid()))
        self.spaces_context.put(request_uri, res=None)
        
        # return a copy of the uri as we dont want changes to the return uri by the caller to affect 
        # how we use the uri
        #
        return (True, request_uri.uri_copy())
    
    def get_spear_request_from_ds(self, spear_request_uri):
        """This function requests the DataStore for a Resource matching the
        argument 'spear_request_uri'. If found, it then requests the DataStore
        for the Resources matching the instructions in the instruction list of
        the found Resource.
                 
        :param spear_request_uri: Uri
        :rtype Resource or None
        """

        rs = None
        
        datastore_uri = self.spaces_context.uri(Resource.BINDING_NS_NAME_DATASTORE + ':')
        spear_uri = self.spaces_context.uri(A2PTask.BINDING_NS_NAME_SPEAR + ':')
        
        try:
            request_rs_list = self.ds.find([(datastore_uri.add("resource").add("type"), spear_uri.add("type").add("request")),
                                            (spear_uri.add("request").add("uri"), spear_request_uri)])
            if (request_rs_list is not None) and (len(request_rs_list) > 0):
                rs = request_rs_list[0]
                rs.set_var("instructions_dict_list", self.get_spear_request_instructions_from_ds(rs))
        except NotFoundException:
            self.logger.log(logging.ERROR, "spear_request_uri (%s) not found in datastore" % (spear_request_uri))
        
        return rs
    
    def get_spear_request_instructions_from_ds(self, rs):
        """This function requests the DataStore for the Resources matching the
        instructions in the instruction list in the argument Resource.
        
        Here we create a list of dictionaries, one dictionary per instruction 
        Resource. Each dictionary contains the instruction's:
        - request_python_code
        - response_python_code
        - error_python_code
        - request_const_dict
        - response_const_dict
        - error_const_dict
        - request[request_params]
        - request[url]
        - response[url]
        - response[ignore]

        :param rs: Resource
        :rtype List of dict
        """

        instruction_dict_list = []
        
        datastore_uri = self.spaces_context.uri(Resource.BINDING_NS_NAME_DATASTORE + ':')
        spear_uri = self.spaces_context.uri(A2PTask.BINDING_NS_NAME_SPEAR + ':')

        instructions_list = rs.get_var("instructions")
        protocol = rs.get_var("protocol")
        hostname = rs.get_var("hostname")
        
        for i in instructions_list:
            try:
                rs_list = self.ds.find([(datastore_uri.add("resource").add("type"), spear_uri.add("type").add("instruction")),
                                        (spear_uri.add("instruction").add("uri"), i)])
                if (rs_list is not None) and (len(rs_list) > 0):
                    dict = {}
                    dict["request_const_dict"] = rs_list[0].get_var("request_const_dict")
                    dict["request_python_code"] = rs_list[0].get_var("request_python_code")
                    dict["response_const_dict"] = rs_list[0].get_var("response_const_dict")
                    dict["response_python_code"] = rs_list[0].get_var("response_python_code")
                    dict["error_const_dict"] = rs_list[0].get_var("error_const_dict")
                    dict["error_python_code"] = rs_list[0].get_var("error_python_code")
                    dict["protocol"] = protocol
                    dict["hostname"] = hostname
                    dict["request"] = rs_list[0].get_var("request")
                    dict["response"] = rs_list[0].get_var("response")
                    
                    instruction_dict_list.append(dict)
            except NotFoundException:
                self.logger.log(logging.ERROR, "instruction (%s) not found in datastore" % i)
                pass
        
        return instruction_dict_list
    
    def add_request_to_immediate_queue(self, request_rs):
        """This function adds the argument Resource to the immediate queue after
        first ensuring that the Resource isn't already on the queue.
        
        :param request_rs: Resource
        """
        
        if (self.is_request_in_queue(self.immediate_queue, request_rs) == False):
            self.immediate_queue.appendleft(request_rs)
        
    def add_request_to_background_queue(self, request_rs):
        """This function adds the argument Resource to the background queue after
        first ensuring that the Resource isn't already on the queue (as may happen
        with poll requests).
        
        :param request_rs: Resource
        """
        
        if (self.is_request_in_queue(self.background_queue, request_rs) == False):
            self.background_queue.appendleft(request_rs)
        
    def is_request_in_queue(self, queue, request_rs):
        """This function searches the argument queue for the argument Resource.
        Matching is based on the value of 'spear:request/uri'.
        
        :param queue: collections.deque
        :param request_rs: Resource
        :rtype Boolean: True if Resource found in queue, otherwise False.
        """
        
        spear_uri = self.spaces_context.uri(A2PTask.BINDING_NS_NAME_SPEAR + ':')
        spear_request_uri = spear_uri.add("request").add("uri")
        
        try:
            it = iter(queue)
            rs = it.next()
            while (rs is not None):
                rs_spear_request_uri = rs.get_single_metadata(spear_request_uri)
                if (rs_spear_request_uri == request_rs.get_single_metadata(spear_request_uri)):
                    return True
                rs = it.next()
        except StopIteration:
            pass
        except IndexError:
            pass
        
        return False
    
    
#    def cb_generate_a2p_request_input(self, method, uri, res, result, context, **kwargs):
#        """This function generates a a2p request and returns the location of 
#        the operation resource associated with the request
#        
#        :param method: <class> or <type>
#        :param uri: The task Uri.
#        :param res: <class> or <type>
#        :param result: <class> or <type>
#        :param context: <class> or <type>
#        :param kwargs: <class> or <type>
#        """
#        
#        self.logger.log(logging.DEBUG, "method (%s), uri (%s), res (%s), result (%s), context (%s)" % (method, uri, res, result, context))
#        
#        service_name = uri.collection(False).split()[-1]
#
#        datastore_uri = self.spaces_context.uri(Resource.BINDING_NS_NAME_DATASTORE + ':')
#        spear_uri = self.spaces_context.uri(A2PTask.BINDING_NS_NAME_SPEAR + ':')
#        a2p_uri = self.spaces_context.uri(A2PTask.BINDING_NS_NAME_A2P + ':')
#        operation_uri = self.spaces_context.uri(A2PTask.BINDING_NS_NAME_OPERATION + ':' + service_name)
#        
#        self.logger.log(logging.DEBUG, "operation_uri (%s)" % operation_uri)
#        
#        ds = DataStore(self.spaces_context.spaces.ns)
#        
#        operations = ds.find([(datastore_uri.add('resource').add('type'), spear_uri.add('type').add('operation')),
#                              (spear_uri.add('operation').add('uri'), operation_uri)])
#        if (operations is not None):
#            id = self.spaces_context.uuid()
#            
#            # right now there is only one operation per request ... this could change in the future
#            operation = operations[0]
#            
#            # set the request parameters on the operation
#            operation.params = res.params
#            request_uri = a2p_uri.add('requests').add(str(id))
#            self.spaces_context.put(request_uri, operation)
#            
#            # return a copy of the uri as we dont want changes to the return uri by the caller to affect 
#            # how we use the uri
#            return (True, request_uri.uri_copy())

   
class A2PProcessThread(Thread):
    """This class represents a thread that is started to process the request
    queues that are populated by A2PTask.

    *Usage examples*::

        example code

    *Common Arguments for Class methods*:
        <arguments>
    
    *Audience*:
        <audience>
    
    *Constants*:
        .. data:: constant_1
        
            constant_1 is used for ......
        
        .. data:: constant_2
        
            constant_2 is used for ......
    """
    
    # Constants
    #
    STATE_LOGGEDOUT = 0
    STATE_LOGGEDIN = 1
    
    def __init__(self, spaces, immediate_queue, background_queue, login_request_rs):
        # Constructor
        #
        # Parameters:
        #     spaces :
        #     immediate_queue :
        #     background_queue : 
        #
        
        Thread.__init__(self)
        
        self.logger = logging.getLogger('eplanning.spear.a2ptask.A2PProcessThread')
        self.logger.log(logging.DEBUG, "spaces (%s), immediate_queue (%s), background_queue (%s)" % (spaces, immediate_queue, background_queue))
        
        self.spaces = spaces
        self.spaces_context = SpacesContext(self.spaces, Queue())
        self.immediate_queue = immediate_queue
        self.background_queue = background_queue
        self.login_request_rs = login_request_rs
        
        # Must use a single instance of HTTP for all requests so we use a single 
        # cookie jar.
        #
        self.http = HTTP()
        
        self.do_shutdown = False
        self.state = A2PProcessThread.STATE_LOGGEDOUT
        
    def run(self):
        """This function is called from Thread.start() once the new Thread is created.
        This is the mainline of the thread.
        """
        
        self.logger.log(logging.DEBUG, "A2PProcessThread started")
        
        # loop, waiting on requests on both immediate and background queues.
        # Exit if task being shutdown.
        #
        while (self.do_shutdown == False):
            # As we have 2 queues to wait on we can't block on either. Next best
            # thing is to sleep and wake-up regularly to check the queues. Also,
            # deque() does not support blocking.
            # 
            
            # check the immediate queue. Only if its empty do we check the
            # background queue. Otherwise we keep processing immediate queue
            # requests until there are no more. After processing of each
            # background queue request we must again check the immediate queue.
            #
            request_rs = None
            
            try:
                request_rs = self.immediate_queue.pop()
                self.logger.log(LoggingLevels.TRACE, "processing immediate queue request (%s)" % request_rs.pretty_print())
            except IndexError:
                self.logger.log(LoggingLevels.TRACE, "immediate queue empty, checking background queue")
                try:
                    request_rs = self.background_queue.pop()
                    self.logger.log(LoggingLevels.TRACE, "processing background queue request (%s)" % request_rs.pretty_print())
                except IndexError:
                    self.logger.log(LoggingLevels.TRACE, "background queue empty")
                    pass
            
            if (request_rs is not None):
                # login to Spear if not already. Don't keep knocking on the door 
                # if it keeps failing otherwise Spear will de-activate the login
                # and we'll never get in. On failure, back-off for a minute and 
                # try again.
                #
                while (self.state == A2PProcessThread.STATE_LOGGEDOUT):
                    self.do_login()
                    if (self.state == A2PProcessThread.STATE_LOGGEDOUT):
                        self.logger.log(logging.ERROR, "Login failure to Spear. Will try again later.")
                        time.sleep(60)
                
                is_ok = self.do_process_operation(request_rs)
                request_rs.set_var("status", is_ok)
                
                # send response Resource.
                #
                response_uri = request_rs.get_var("response_uri")
                self.spaces_context.put(response_uri.add("response"), res=request_rs)
                
            self.logger.log(LoggingLevels.TRACE, "sleeping")
            time.sleep(1)
        
    def shutdown(self):
        """This function overrides BaseServer::shutdown().
        """
        
        self.logger.log(LoggingLevels.TRACE, "A2PProcessThread stopped")
        
        self.do_shutdown = True
        
    def do_login(self):
        """This function processes the login request resource to log-in to Spear. 
        """
        
        if (self.do_process_operation(self.login_request_rs) is True):
            self.state = A2PProcessThread.STATE_LOGGEDIN
        
    def do_process_operation(self, request_rs):
        """This function processes a request resource.
        
        :param request_rs: Resource
        :rtype: Boolean - True for successful processing, otherwise False.
        """

        self.logger.log(LoggingLevels.TRACE, "process_operation(): request_rs (%s)" % request_rs)
        
        arguments_dict = {}
        if (request_rs.has_var("arguments_dict")):
            arguments_dict = request_rs.get_var("arguments_dict")
        
        # get all the instructions for the operation
        for instruction_dict in request_rs.get_var("instructions_dict_list"):
            self.logger.log(LoggingLevels.TRACE, "instruction_dict (%s)" % instruction_dict)
            
            request_dict = instruction_dict["request"]
            response_dict = instruction_dict["response"]
            
            request_const_dict = instruction_dict["request_const_dict"]
            response_const_dict = instruction_dict["response_const_dict"]
            error_const_dict = instruction_dict["error_const_dict"]
            
            # Each request contains the following items that are made available to
            # the python code sections of each instruction.
            #
            # - 'arguments_dict'
            #   - a dictionary of user request arguments. Keys of this dictionary
            #     must match keys in an instruction's "request_params" for the 
            #     key value to be useful.
            #
            # Each request instruction contains the following items that are made 
            # available to the python code sections of each instruction.
            #
            # - 'request_const_dict'
            #   - a dictionary made available to "request_python_code".
            #
            # - 'response_const_dict'
            #   - a dictionary made available to "response_python_code" and HTML
            #     parsing. Keys in this dictionary are searched for in the HTML
            #     to determine the values for the keys. Values are saved into
            #     the dictionary and become available to 'response_python_code'.
            #
            # - 'error_const_dict'
            #   - a dictionary made available to "error_python_code" and HTML
            #     parsing. 
            #
            # The following items are made available to "request_python_code":
            #
            # - 'post_data'
            #   - a dictionary that can be used to send key/value pairs in POST 
            #     requests.
            #
            # Any variable substitutions required for the instruction's "url" 
            # are taken from:
            #
            # - the user's 'arguments_dict', if the variable exists, otherwise
            # - the instruction's 'request_params' dictionary
            #
            # There is a local Boolean variable 'is_ok' that can be set False
            # to abort instruction processing based on usability errors (eg. 
            # login failure) from Spear. 
            #

            post_data = {}
            request_params = request_dict["request_params"]
            is_ok = True
            
            request_python_code = instruction_dict["request_python_code"]
            if (request_python_code is not None):
                self.logger.log(LoggingLevels.TRACE, "processing request_python_code (%s)" % request_python_code.strip())
                exec request_python_code.strip()
            
            # Note: I tried using 'urlparse.urlunparse()' and 'urlparse.urlunsplit()'
            #       but they both resulted in a double slash between the hostname
            #       and the path when 'request_dict' requires a full path to
            #       be substituted.
            #
            
#            url_tuple = (instruction_dict["protocol"], instruction_dict["hostname"], request_dict["url"]["path"], "", request_dict["url"]["query"], request_dict["url"]["fragment"])
#            request = urlparse.urlunparse(url_tuple)
            request_url = instruction_dict["protocol"] + '://' + instruction_dict["hostname"] + request_dict["url"]["path"]
            if (len(request_dict["url"]["query"]) > 0):
                request_url += '?' + request_dict["url"]["query"]
            if (len(request_dict["url"]["fragment"]) > 0):
                request_url += '#' + request_dict["url"]["fragment"]
            
#            url_tuple = (instruction_dict["protocol"], instruction_dict["hostname"], response_dict["url"]["path"], "", response_dict["url"]["query"], response_dict["url"]["fragment"])
#            response_url = urlparse.urlunparse(url_tuple)
            
            response_url = instruction_dict["protocol"] + '://' + instruction_dict["hostname"] + response_dict["url"]["path"]
            if (len(response_dict["url"]["query"]) > 0):
                response_url += '?' + response_dict["url"]["query"]
            if (len(response_dict["url"]["fragment"]) > 0):
                response_url += '#' + response_dict["url"]["fragment"]
            
            self.logger.log(LoggingLevels.TRACE, "===== 1 request_url (%s)." % request_url)
            self.logger.log(LoggingLevels.TRACE, "===== 1 response_url (%s)." % response_url)
             
            # perform variable substitution into 'request_url' and 'response_url'.
            #
            request_url = self.do_url_argument_replacement(request_url, arguments_dict)
            request_url = self.do_url_argument_replacement(request_url, request_params)
            response_url = self.do_url_argument_replacement(response_url, arguments_dict)
            response_url = self.do_url_argument_replacement(response_url, request_params)
            
            self.logger.log(logging.DEBUG, "requesting url (%s)." % request_url)
            self.logger.log(logging.DEBUG, "expected response_url (%s)." % response_url)
            
            # make the HTTP request. 
            #
            (code, real_response_url, response) = self.http.issue_request(request_url, post_data)
            
            if (code < 0):
                # IO error in communicating with Spear.
                #
                self.logger.log(logging.ERROR, "IO error communicating with Spear. Abandoning instructions for request (%s)." % request_rs.pretty_print())
                is_ok = False
                break
            
            elif (code != httplib.OK):
                # Error from Spear. Stop processing instruction list.
                #
                self.logger.log(logging.ERROR, "HTTP return code (%s) from Spear not OK. Abandoning instructions for request (%s)." % (code, request_rs.pretty_print()))
                is_ok = False
                break
            
            # check the response's URL is the same as the expected URL (from instruction)
            #
            elif (response_url != real_response_url):
                self.logger.log(logging.ERROR, "HTTP response URL (%s) from Spear different to that expected (%s). Abandoning instructions for request (%s)." % (real_response_url, response_url, request_rs.pretty_print()))
                is_ok = False
                break
            
            # should we process the response HTML/PDF?
            #
            elif (response_dict["ignore_output"] is False):
                self.logger.log(logging.DEBUG, "processing response...")
                
                error_python_code = instruction_dict["error_python_code"]
                if (error_python_code is not None):
                    self.logger.log(LoggingLevels.TRACE, "processing error_python_code (%s)" % error_python_code.strip())
                    error_python_code = error_python_code.strip()
                response_python_code = instruction_dict["response_python_code"]
                if (response_python_code is not None):
                    self.logger.log(LoggingLevels.TRACE, "processing response_python_code (%s)" % response_python_code.strip())
                    response_python_code = response_python_code.strip()
                
                if (response_dict["output_format"] == "html"):
                    parse_tuple_list = []
                    html_tag_list = []
                    
                    # strip out guts of <img /> tags to remove bad tag that kills HTMLParser.
                    #
                    response = re.sub(r'<img.*>', r'<img/>', response)
#                    self.logger.log(logging.DEBUG, "@@@@@@@@@@@@@@@@@@@@@@@@@ response w/o img tags (%s)" % response)
                    
                    # Parse returned HTML.
                    #
                    try:
                        self.parser = SpearHTMLParser(html_tag_list)
                        self.parser.feed(response)
                        self.parser.close()
                    except HTMLParseError as e:
                        self.logger.log(logging.ERROR, "HTML Parsing Error (%s)" % e)
                    except:
                        self.logger.log(logging.ERROR, "HTML Parsing Error")
                        
                    self.logger.log(logging.DEBUG, "html_tag_list (%s)" % html_tag_list)
                    
                    parse_tuple_list = self.process_tags(html_tag_list, response_const_dict, error_const_dict)
                    
                    self.logger.log(logging.DEBUG, "parse_tuple_list (%s)" % parse_tuple_list)
                    
                    # HTTP status code doesn't tell us everything about the success 
                    # or not of the request. For example, if login fails Spear will
                    # re-display the login page with an error message; however the 
                    # status code is 200 - OK. So we must perform the instruction's
                    # error python code BEFORE the response python code so we know
                    # what happened.
                    #
                    
                    error_python_code = error_python_code.strip()
                    if (len(error_python_code) > 0):
                        exec error_python_code
                    
                    if (is_ok is True):
                        # All OK. Parse page for any data we require.
                        #
                        response_python_code = response_python_code.strip()
                        if (len(response_python_code) > 0):
                            exec response_python_code
                    else:
                        self.logger.log(logging.ERROR, "Error detected in Spear response. Abandoning instructions for request (%s)." % request_rs.pretty_print())
                        break
                
                elif (response_dict["output_format"] == "pdf"):
                    # We cannot parse from a PDF so just save it straight to a Resource.
                    #
                    parse_tuple_list = []
                    parse_tuple_list.append(("pdf", response))
                    
                    response_python_code = response_python_code.strip()
                    if (len(response_python_code) > 0):
                        exec response_python_code
            else:
                self.logger.log(logging.DEBUG, "ignoring response")
                    
            self.logger.log(LoggingLevels.TRACE, "HTTP return code (%s)" % code)
#            self.logger.log(logging.DEBUG, "@@@@@@@@@@@@@@@@@@@@@@@@@ process_operation(): HTTP response (%s)" % response)

        return is_ok
    
    def process_tags(self, html_tag_list, response_const_dict, error_const_dict):
        """This function processes the argument 'html_tag_list' - a list of HTML 
        tags, looking for Spear ids as configured into the arguments
        'response_const_dict' and 'error_const_dict'. When a tag is found the
        tag's instructions are used to determine the location of the data. The
        tag name and the data are then appended (as a tuple) to a list. The
        resultant list of tuples is returned.
        
        :param html_tag_list: List - list of HTML tags, attributes and data.
        :param response_const_dict: Dictionary - configured dictionary of Spear
        ids, with parsing instructions, to search for in successful HTML responses.
        :param error_const_dict: Dictionary - configured dictionary of Spear
        ids, with parsing instructions, to search for to help determine if the 
        response HTML was reporting an error or not.
        :rtype: List - list of Spear id/value tuples.
        """
        
        self.logger.log(LoggingLevels.TRACE, "response_const_dict (%s)" % response_const_dict)
        
        parse_tuple_list = []
        
        for i in range(0, len(html_tag_list)):
            html_attr_dict = html_tag_list[i]["attr_dict"]
            for attr_key in html_attr_dict:
                attr_value = html_attr_dict[attr_key]
                
                # Note: Tag ids in Spear are not consistant in their casing - sometimes
                #       lowercase, sometimes camel-case. So we must insist that the 
                #       keys in 'response_const_dict' are in lowercase, and convert the
                #       HTML attribute value to lowercase before checking if its in
                #       'response_const_dict'.
                # 
                attr_value = attr_value.lower()
                
                self.logger.log(LoggingLevels.TRACE, "attr_key (%s), attr_value (%s)" % (attr_key, attr_value))
                if (attr_value in response_const_dict):
                    t = self.process_spear_tag(attr_value, response_const_dict[attr_value], html_tag_list, i)
                    if (t is not None):
                        parse_tuple_list.append(t)
                elif (attr_value in error_const_dict):
                    t = self.process_spear_tag(attr_value, error_const_dict[attr_value], html_tag_list, i)
                    if (t is not None):
                        parse_tuple_list.append(t)
                else:
                    pass
        
        return parse_tuple_list
    
    def process_spear_tag(self, spear_id, config_attr_dict, html_tag_list, i):
        """This function determines the data for the argument 'spear_id' using
        the parsing instructions in the argument 'config_attr_dict'. Data is
        parsed from the argument 'html_tag_list' starting from position 'i'.
        If data is found then a tuple(spear_id, data) is returned.
        
        :param spear_id: String - Spear data id for which we are parsing for data.
        :param config_attr_dict: Dictionary - Configured parsing instructions
        for 'spear_id'.
        :param html_tag_list: List - list of HTML tags, attributes and data.
        :param i: int - current index into 'html_tag_list' from which to start
        applying parsing instructions.
        :rtype: tuple or None.
        """
        
        self.logger.log(LoggingLevels.TRACE, "spear_id (%s), config_attr_dict (%s)" % (spear_id, config_attr_dict))
        
        tagdata = html_tag_list[i]["data"]
        html_attr_dict = html_tag_list[i]["attr_dict"]
        do_parse = True
        i2 = 0

        # check "tagsequence"
        #
        if (len(config_attr_dict["tagsequence"]) > 0):
            config_tagsequence_list = config_attr_dict["tagsequence"].split()
            for j in range(0, len(config_tagsequence_list)):
                i2 = i + j + 1
                if (config_attr_dict["forward"] is False):
                    i2 = i - j - 1
                self.logger.log(LoggingLevels.TRACE, "spear_tagsequence_list[%s] (%s), html_tag_list[%s]['tag'] (%s)" % (j, config_tagsequence_list[j], i2, html_tag_list[i2]["tag"]))
                if (config_tagsequence_list[j] <> html_tag_list[i2]["tag"]):
                    self.logger.log(logging.ERROR, "Tag (%s) not found in 'tagsequence' list for Spear attribute (%s)" % (config_tagsequence_list[j], spear_id))
                    do_parse = False
                    break
                elif (j == (len(config_tagsequence_list) - 1)):
                    tagdata = html_tag_list[i2]["data"]
                    html_attr_dict = html_tag_list[i2]["attr_dict"]
        
        if (do_parse is True):
            # check "tagattribute"
            #
            if (len(config_attr_dict["tagattribute"]) > 0):
                if (config_attr_dict["tagattribute"] in html_attr_dict):
                    self.logger.log(LoggingLevels.TRACE, "Value (%s) saved to Spear attr name (%s)" % (html_attr_dict[config_attr_dict["tagattribute"]], spear_id))
                    return (spear_id, html_attr_dict[config_attr_dict["tagattribute"]])
                else:
                    self.logger.log(logging.ERROR, "Configured 'tagattribute' (%s) not found for Spear tag (%s)" % config_attr_dict["tagattribute"], spear_id)
            else:
                self.logger.log(LoggingLevels.TRACE, "Value (%s) saved to Spear attr name (%s)" % (tagdata, spear_id))
                return (spear_id, tagdata)
        
        return None
                            
    def do_url_argument_replacement(self, request_url, params_dict):
        """This function performs replacements in the argument 'request_url',
        substituting keys with values from 'params_dict'. 
        
        :param request_url: String
        :param params_dict: dict
        :rtype: String - resultant Url
        """
        
        for p in params_dict:
            p_sub = '${' + p + '}'
            if (request_url.find(p_sub) > 0):
                request_url = request_url.replace(p_sub, params_dict[p])
        
        return request_url
    
    def cast_data(self, type, data):
        """This function converts the argument String 'data' to the type specified
        by the argument 'type'. The cast data is returned.
        
        :param type: String
        :param data: String
        :rtype Any
        """
        
        self.logger.log(LoggingLevels.TRACE, "cast_data(): type (%s), data (%s)" % (type, data))
        cast_data = None
        
        # check the type of the attribute being parsed.
        #
        if (type == Resource.KEY_URI_YARRA_TYPE_NONE):
            cast_data = None
        elif (type == Resource.KEY_URI_YARRA_TYPE_BOOLEAN):
            if (len(data) > 0):
                try:
                    cast_data = bool(data)
                except:
                    cast_data = False
            else:
                cast_data = False
        elif (type == Resource.KEY_URI_YARRA_TYPE_INT):
            if (len(data) > 0):
                try:
                    cast_data = int(data)
                except:
                    cast_data = 0
            else:
                cast_data = 0
        elif (type == Resource.KEY_URI_YARRA_TYPE_LONG):
            if (len(data) > 0):
                try:
                    cast_data = long(data)
                except:
                    cast_data = 0
            else:
                cast_data = 0
        elif (type == Resource.KEY_URI_YARRA_TYPE_FLOAT):
            if (len(data) > 0):
                try:
                    cast_data = float(data)
                except:
                    cast_data = 0.0
            else:
                cast_data = 0.0
        elif (type == Resource.KEY_URI_YARRA_TYPE_UNICODE):
            if (len(data) > 0):
                cast_data = unicode(data)
            else:
                cast_data = u""
        elif (type == Resource.KEY_URI_YARRA_TYPE_STRING):
            if (len(data) > 0):
                cast_data = data
            else:
                cast_data = ""
        elif (type == Resource.KEY_URI_YARRA_TYPE_URI):
            if (len(data) > 0):
                cast_data = Uri(data)
            else:
                cast_data = Uri("")
        elif (type == Resource.KEY_URI_DUBLINCORE_DATE):
            # Note: Spear is returning dates in different formats. Some such as
            #       'sid002b_date_lodged_with_responsible_authority' are returned 
            #       with the format:
            #
            #       dd/mm/YYYY
            #
            #       while others such as 'sid004_date' are returned as:
            #
            #       YYYY-mm-dd hh:MM:ss.s
            #
            #       However a browser always sees the dates as:
            #
            #       dd/mm/YYYY
            #
            #       So, here we will normalise the dates to the format:
            #
            #       dd/mm/YYYY
            #
            
            try:
                # This code validates the date format, even though it looks
                # like we could simply assign 'data' to 'cast_data'. It will
                # generate an exception if the format is not as described.
                # 
                dt = datetime.strptime(data, "%d/%m/%Y")
                cast_data = dt.strftime("%d/%m/%Y")
            except ValueError:
                try:
                    dt = datetime.strptime(data, "%Y-%m-%d %H:%M:%S.%f")
                    cast_data = dt.strftime("%d/%m/%Y")
                except ValueError:
                    cast_data = ""
            
            self.logger.log(LoggingLevels.TRACE, "cast_data(): input date (%s), output date (%s)" % (data, cast_data))
        
        return cast_data
    
#    def cb_issue_a2p_request(self, method, uri, new_uri, result, context, **kwargs):
#        """This function issues the a2p request by executing all the instructions 
#        of the operation associated without the request.
#        
#        :param param_1: <class> or <type>
#        :param param_2: <class> or <type>
#        :rtype: <return type>
#        """
#        
#        if uri.split2()[-1] == 'response':
#            # just ignore responses
#            return (False, None)
#        
#        # get the request resource
#        operation_resource = self.spaces_context.get(new_uri)
#        rs = self.process_operation(operation_resource, context)
#        
#        # put the response back into spaces
#        self.spaces_context.put(uri.add('response'), rs)
    

class SpearHTMLParser(HTMLParser):
    """Internal class used by A2PProcessThread to process Spear pages.
    """

    def __init__(self, tag_list):
        # Constructor
        #
        # Parameters:
        #     attributes :
        #
        
        HTMLParser.__init__(self)
        
        self.logger = logging.getLogger('eplanning.spear.a2ptask.SpearHTMLParser')
        
        self.tag_list = tag_list
        self.get_data = False
        
    def handle_starttag(self, tag, attrs):
        """This function is called by HTMLParser when an HTML start tag is
        encountered. The tag's name and attributes are passed.
        
        :param tag: String
        :param attrs: List of (name, value) pairs
        """
        
        self.logger.log(LoggingLevels.TRACE, "tag (%s) attrs (%s)" % (tag, attrs))
        
        attr_dict = {}
        for (name, value) in attrs:
            if (value is not None):
                attr_dict[name] = value
        
        tag_dict = {}
        tag_dict["tag"] = tag
        tag_dict["data"] = ""
        tag_dict["attr_dict"] = attr_dict
        self.tag_list.append(tag_dict)
        
        self.get_data = True
        
    def handle_endtag(self, tag):
        """This function is called by HTMLParser when an HTML end tag is
        encountered. The tag's name is passed.
        
        :param tag: String
        """
        
        self.logger.log(LoggingLevels.TRACE, "========  endtag" )
        self.get_data = False
    
    def handle_data(self, data):
        """This function is called by HTMLParser when arbitrary data is
        encountered. The data is passed.
        
        :param data: String
        """
        
        if (self.get_data is True) and (data is not None) and (len(data.strip()) > 0):
            tag_dict = self.tag_list[-1]
            tag_dict["data"] = data.strip()
            
            self.logger.log(LoggingLevels.TRACE, "saving tag (%s) data (%s)" % (tag_dict["tag"], data.strip()))
        else:
            self.logger.log(LoggingLevels.TRACE, "========  not saving data (%s)" % data.strip())
            
    def handle_comment(self, data):
        """This function is called by HTMLParser when an HTML comment is
        encountered. The comment's contents is passed.
        
        :param data: String
        """
        
        self.logger.log(LoggingLevels.TRACE, "========  comment" )

    def handle_charref(self, name):
        """This function is called by HTMLParser when an HTML character reference
        (ie. "&#..;) is encountered. The reference is passed.
        
        :param name: String
        """
        
        self.logger.log(LoggingLevels.TRACE, "========  charref" )
        
    def handle_entityref(self, name):
        """This function is called by HTMLParser when a general HTML entity
        reference (ie. &name;) is encountered. The reference is passed.
        
        :param name: String
        """
        
        self.logger.log(LoggingLevels.TRACE, "========  entityref" )
    
    def handle_decl(self, decl):
        """This function is called by HTMLParser when an SGML declaration is
        encountered. The 'decl' parameter will be the entire contents of the 
        declaration inside the <!...> markup.
        
        :param decl: String
        """
        
        self.logger.log(LoggingLevels.TRACE, "========  decl" )
    
    def handle_pi(self, data):
        """This function is called by HTMLParser when an SGML processing instruction
        (ie. <?proc color='red'>) is encountered. The 'data' parameter will contain 
        the entire processing instruction.
        
        :param data: String
        """
        
        self.logger.log(LoggingLevels.TRACE, "========  pi" )
    
    def finish(self):
        self.logger.log(LoggingLevels.TRACE, "========  finish" )
        return self.base